Lambda関数のhandlerの外側でRDS Proxyの接続をした場合の処理時間を計測してみた
RDS Proxyの接続を使い回した場合の影響を知りたい
こんにちは、のんピ(@non____97)です。
以下記事でLambda関数からRDS Proxy経由でAmazon Aurora DBクラスターに接続してみました。
その際のLambda関数ではRDS Proxyの接続をhandler内で行っており、Lambda関数を実行するたびにRDS Proxyに接続をしていました 。
RDS Proxyの接続をhandlerの外側にした場合は、RDS Proxyの接続を維持することができ、ウォームスタート時には接続処理をスキップできるためパフォーマンスの向上が期待できます。
参考:
この情報を見て、「実際Lambda関数のhandlerの外側でRDS Proxyの接続をすると処理時間にどのぐらい影響を与えるのか」が非常に気になったので検証してみます。
こちらのコードのリポジトリは以下になります。
使用するLambda関数
RDS Proxyの接続をhandlerの外側で実行するLambda関数と、内側で実行するLambda関数を用意しました。
RDS Proxyの接続をhandlerの内側で実行するLambda関数はコネクションのクローズもhandler内で行っています。
import { getSecretValue } from "../utils/getSecretValue";
import { dbConnect } from "../utils/dbConnect";
import { QueryResult } from "../utils/table";
const secret = await getSecretValue();
const dbClient = await dbConnect(secret);
export const handler = async (): Promise<QueryResult | Error> => {
// Query
const beforeInsertQuery = await dbClient.query("SELECT * FROM test_table");
console.log(beforeInsertQuery.rows);
await dbClient.query("INSERT INTO test_table (name) VALUES ('non-97')");
const afterInsertQuery = await dbClient.query("SELECT * FROM test_table");
console.log(afterInsertQuery.rows);
return {
beforeInsertQueryRows: beforeInsertQuery.rows,
afterInsertQueryRows: afterInsertQuery.rows,
};
};
import { getSecretValue } from "../utils/getSecretValue";
import { dbConnect } from "../utils/dbConnect";
import { QueryResult } from "../utils/table";
const secret = await getSecretValue();
export const handler = async (): Promise<QueryResult | Error> => {
const dbClient = await dbConnect(secret);
// Query
const beforeInsertQuery = await dbClient.query("SELECT * FROM test_table");
console.log(beforeInsertQuery.rows);
await dbClient.query("INSERT INTO test_table (name) VALUES ('non-97')");
const afterInsertQuery = await dbClient.query("SELECT * FROM test_table");
console.log(afterInsertQuery.rows);
dbClient.end();
return {
beforeInsertQueryRows: beforeInsertQuery.rows,
afterInsertQueryRows: afterInsertQuery.rows,
};
};
Prepared Statementsでクエリを発行してしまうとピン留めされてしまうので、Prepared Statementsは使用しません。ピン留めについては以下記事とAWS公式ドキュメントをご覧ください。
また、こちらのLambda関数ではtop-level awaitを使用しています。
そのため、ターゲットはtop-level awaitをサポートしているv14.8以降を指定し、フォーマットはCommonJSではなくES Modulesにしています。
また、インポートするモジュールをNodejsFunction側でも明示的に指定する必要があったのでnodeModulesでLambda関数で使用するモジュールを指定してあげます。
new nodejs.NodejsFunction(this, "DbAccessDbconnectOutsideHandlerFunction", {
entry: path.join(
__dirname,
"../src/lambda/handlers/db-access-dbconnect-outside-handler.ts"
),
runtime: lambda.Runtime.NODEJS_14_X,
bundling: {
minify: true,
sourceMap: true,
externalModules: ["pg-native"],
target: "node14.19",
tsconfig: path.join(__dirname, "../src/lambda/tsconfig.json"),
format: nodejs.OutputFormat.ESM,
nodeModules: ["@aws-sdk/client-secrets-manager", "pg"],
},
environment: {
PROXY_ENDPOINT: rdsProxy.endpoint,
SECRET_ID: dbAdminSecret.secretArn,
NODE_OPTIONS: "--enable-source-maps",
},
role: dbAccessFunctionIamRole,
logRetention: logs.RetentionDays.TWO_WEEKS,
tracing: lambda.Tracing.ACTIVE,
securityGroups: [dbClientSg],
vpc,
vpcSubnets: vpc.selectSubnets({
subnetType: ec2.SubnetType.PRIVATE_WITH_NAT,
}),
});
top-level awaitを使用するには以下の条件を満たす必要があります。
moduleオプションが以下のいずれかes2022esnextsystemnodenext
targetオプションが以下のバージョン以上es2017
こちらの条件を満たすようにLambda関数のトランスコンパイルに使用するtsconfig.jsonを用意してあげます。
{
"extends": "../../tsconfig.json",
"compilerOptions": {
"target": "es2019",
"module": "es2022",
"moduleResolution": "node",
"allowSyntheticDefaultImports": true,
"esModuleInterop":true
}
}
計測してみた
計測のレギュレーション
計測するにあたってのレギュレーションは以下の通りです。
- メモリを128MB割り当てたLambda関数からRDS Proxy経由でAurora DBクラスターに接続
- Lambda関数から簡単なSQL(
SELECTとINSERT)を発行 - 計測は以下の状態で行う
- DBのテーブルがクリアされている
- RDS ProxyとAurora DBクラスター間のコネクションが無い
- Lambda関数とRDS Proxy間のコネクションが無い
- プレウォーミング(
Provisioned Concurrency)は使用しない - 処理時間(
Duration)とコールドスタートの所要時間(Init Duration)をCloudWatch Logs Insightsで集計 - CloudWatchで以下メトリクスを確認
- RDS Proxyの現在のクライアント接続の数(
ClientConnections) - RDS Proxyの現在のデータベース接続の数(
DatabaseConnections) - RDS Proxyの現在ピン留めされているデータベース接続の数(
DatabaseConnectionsCurrentlySessionPinned) - Lambda関数のイベントを処理している関数インスタンスの数(
ConcurrentExecutions)
- RDS Proxyの現在のクライアント接続の数(
- Aurora DBクラスターはシングルAZ構成
- Lambda関数、RDS ProxyはマルチAZ構成
計測パターン
計測パターンは以下の4つです。
- RDS Proxyの接続をhandlerの外側で実行するLambda関数 × 直列100回実行
- RDS Proxyの接続をhandlerの内側で実行するLambda関数 × 直列100回実行
- RDS Proxyの接続をhandlerの外側で実行するLambda関数 × 並列100回実行
- RDS Proxyの接続をhandlerの内側で実行するLambda関数 × 並列100回実行
直列実行 VS 並列実行だとウォームスタートとコールドスタートの差で勝負にならないので、直列実行 VS 並列実行というよりも直列実行内、並列実行内で比較する形をとります。
また、各パターンの計測する際は各パターン毎に準備したステートマシンを実行して計測します。
// State Machine Tasks
const patternDbConnectTasks = [
new tasks.LambdaInvoke(this, "Pattern1DbConnectTask", {
lambdaFunction: dbAccessDbConnectOutsideHandlerFunction,
invocationType: tasks.LambdaInvocationType.REQUEST_RESPONSE,
payload: sfn.TaskInput.fromObject({
payload: sfn.JsonPath.stringAt("$"),
}),
outputPath: "$.StatusCode",
}),
new tasks.LambdaInvoke(this, "Pattern2DbConnectTask", {
lambdaFunction: dbAccessDbConnectInsideHandlerFunction,
invocationType: tasks.LambdaInvocationType.REQUEST_RESPONSE,
payload: sfn.TaskInput.fromObject({
payload: sfn.JsonPath.stringAt("$"),
}),
outputPath: "$.StatusCode",
}),
new tasks.LambdaInvoke(this, "Pattern3DbConnectTask", {
lambdaFunction: dbAccessDbConnectOutsideHandlerFunction,
invocationType: tasks.LambdaInvocationType.EVENT,
payload: sfn.TaskInput.fromObject({
payload: sfn.JsonPath.stringAt("$"),
}),
outputPath: "$.StatusCode",
}),
new tasks.LambdaInvoke(this, "Pattern4DbConnectTask", {
lambdaFunction: dbAccessDbConnectInsideHandlerFunction,
invocationType: tasks.LambdaInvocationType.EVENT,
payload: sfn.TaskInput.fromObject({
payload: sfn.JsonPath.stringAt("$"),
}),
outputPath: "$.StatusCode",
}),
];
// State Machine
patternDbConnectTasks.forEach((patternDbConnectTask, index) => {
const createNumberArrayTask = new tasks.LambdaInvoke(
this,
`Pattern${index + 1}CreateNumberArrayTask`,
{
lambdaFunction: createNumberArrayFunction,
payload: sfn.TaskInput.fromObject({
number: sfn.JsonPath.stringAt("$.numberForInputMap"),
}),
}
);
const map = new sfn.Map(this, `Pattern${index + 1}MapState`, {
maxConcurrency: index < 2 ? 1 : 0,
itemsPath: sfn.JsonPath.stringAt("$.Payload.numberArray"),
});
new sfn.StateMachine(this, `Pattern${index + 1}StateMachine`, {
definition: createNumberArrayTask
.next(map.iterator(patternDbConnectTask))
.next(new sfn.Succeed(this, `Pattern${index + 1}SuccessState`)),
logs: {
destination: stateMachineLogGroup,
level: sfn.LogLevel.ALL,
},
tracingEnabled: true,
});
});
100回Lambda関数を直列 or 並列実行したい場合は、ステートマシンに以下のJSONを渡します。
{
"numberForInputMap": 100
}
CloudWatch Logs Insightsのクエリ
各パターン実行後に以下のCloudWatch Logs Insightsのクエリを実行して集計します。
filter @type = "REPORT" | stats avg(@duration) as duration_avg, max(@duration) as duration_max, min(@duration) as duration_min, pct(@duration, 25) as duration_pct25, pct(@duration, 50) as duration_pct50, pct(@duration, 75) as duration_pct75, count(@duration) as duration_count, avg(@initDuration) as initDuration_avg, max(@initDuration) as initDuration_max, min(@initDuration) as initDuration_min, pct(@initDuration, 25) as initDuration_pct25, pct(@initDuration, 50) as initDuration_pct50, pct(@initDuration, 75) as initDuration_pct75, count(@initDuration) as initDuration_count | display duration_avg, duration_max, duration_min, duration_pct25, duration_pct50, duration_pct75, duration_count, initDuration_avg, initDuration_max, initDuration_min, initDuration_pct25, initDuration_pct50, initDuration_pct75, initDuration_count
CloudWatch Logs Insights のクエリ構文は以下AWS公式ドキュメントをご覧ください。
各パターン終了毎にDBで行う作業
各パターン終了毎にDBで行う作業は以下の通りです。EC2インスタンスからRDS Porxyを経由せずAurora DBクラスターに接続してテーブルをクリアしたり、コネクションを削除したりします。
# Secrets ManagerからAurora DBクラスターのシークレットを取得
$ get_secrets_value=$(aws secretsmanager get-secret-value \
--secret-id prd-db-cluster/AdminLoginInfo \
--region us-east-1 \
| jq -r .SecretString)
# シークレットを環境変数にセット
$ export PGHOST=$(echo "${get_secrets_value}" | jq -r .host)
$ export PGPORT=$(echo "${get_secrets_value}" | jq -r .port)
$ export PGDATABASE=$(echo "${get_secrets_value}" | jq -r .dbname)
$ export PGUSER=$(echo "${get_secrets_value}" | jq -r .username)
$ export PGPASSWORD=$(echo "${get_secrets_value}" | jq -r .password)
# Aurora DBクラスターに接続
$ psql
# テーブルを一度削除する
=> DROP TABLE test_table;
# テーブルを作成し直す
=> CREATE TABLE test_table (
id SERIAL NOT NULL,
name VARCHAR(255) NOT NULL,
created_at TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP,
PRIMARY KEY (id)
);
# 自分以外のコネクションを確認する
=> SELECT *
FROM pg_stat_activity
WHERE datname = 'testDB'
AND pid <> pg_backend_pid();
# 自分以外のコネクションを切断する
=> SELECT pg_terminate_backend(pid)
FROM pg_stat_activity
WHERE datname = 'testDB'
AND pid <> pg_backend_pid();
パターン1. RDS Proxyの接続をhandlerの外側で実行するLambda関数 × 直列100回実行
まず、RDS Proxyの接続をhandlerの外側で実行するLambda関数を直列で繋いだ場合を試します。
ステートマシンを実行すると以下のように正常に終了しました。
X-Rayトレースからタイムラインを確認すると、確かに直列で実行されていることが確認できます。
実行時のCloudWatchメトリクスは以下のようになっていました。
ClientConnectionsとDatabaseConnectionsは共に1であることからRDS Proxyへのコネクションを使い回していることが分かります。
CloudWatch Logs Insightsで集計した結果は以下の通りです。
| フィールド | 値 |
|---|---|
| duration_avg | 45.8541 |
| duration_max | 237.3 |
| duration_min | 13.29 |
| duration_pct25 | 23.33 |
| duration_pct50 | 34.88 |
| duration_pct75 | 51.42 |
| duration_count | 100 |
| initDuration_avg | 696.14 |
| initDuration_max | 696.14 |
| initDuration_min | 696.14 |
| initDuration_pct25 | 696.14 |
| initDuration_pct50 | 696.14 |
| initDuration_pct75 | 696.14 |
| initDuration_count | 1 |
initDuration_countが1になっていることからコールドスタートになったのは一回のみだったことが分かります。
パターン2. RDS Proxyの接続をhandlerの内側で実行するLambda関数 × 直列100回実行
続いて、RDS Proxyの接続をhandlerの内側で実行するLambda関数を直列で繋いだ場合を試します。
ステートマシンを実行すると以下のように正常に終了しました。
X-Rayトレースからタイムラインを確認すると、確かに直列で実行されていることが確認できます。
実行時のCloudWatchメトリクスは以下のようになっていました。
ClientConnectionsとDatabaseConnectionsは共に1であることからRDS Proxyへのコネクションを使い回していることが分かります。
CloudWatch Logs Insightsで集計した結果は以下の通りです。
| フィールド | 値 |
|---|---|
| duration_avg | 119.3956 |
| duration_max | 261.13 |
| duration_min | 82.56 |
| duration_pct25 | 94.8905 |
| duration_pct50 | 105.2851 |
| duration_pct75 | 124.7844 |
| duration_count | 100 |
| initDuration_avg | 690.17 |
| initDuration_max | 690.17 |
| initDuration_min | 690.17 |
| initDuration_pct25 | 690.17 |
| initDuration_pct50 | 690.17 |
| initDuration_pct75 | 690.17 |
| initDuration_count | 1 |
initDuration_countが1になっていることからコールドスタートになったのは一回のみだったことが分かります。
パターン3. RDS Proxyの接続をhandlerの外側で実行するLambda関数 × 並列100回実行
続いて、RDS Proxyの接続をhandlerの外側で実行するLambda関数を並列で繋いだ場合を試します。
ステートマシンを実行すると以下のように正常に終了しました。
X-Rayトレースからタイムラインを確認すると、確かに並列で実行されていることが確認できます。
実行時のCloudWatchメトリクスは以下のようになっていました。
Lambda関数が最大33多重で実行され、Lambda関数からRDS Proxyへのコネクションが19個あることが分かります。
CloudWatch Logs Insightsで集計した結果は以下の通りです。
| フィールド | 値 |
|---|---|
| duration_avg | 113.3586 |
| duration_max | 341.75 |
| duration_min | 25.12 |
| duration_pct25 | 61.7404 |
| duration_pct50 | 97.3888 |
| duration_pct75 | 146.7171 |
| duration_count | 100 |
| initDuration_avg | 801.1223 |
| initDuration_max | 1273.24 |
| initDuration_min | 616.83 |
| initDuration_pct25 | 729.95 |
| initDuration_pct50 | 794.79 |
| initDuration_pct75 | 842.5 |
| initDuration_count | 30 |
initDuration_countが30になっていることから30回コールドスタートが発生したことが分かります。
パターン4. RDS Proxyの接続をhandlerの内側で実行するLambda関数 × 並列100回実行
最後に、RDS Proxyの接続をhandlerの内側で実行するLambda関数を並列で繋いだ場合を試します。
ステートマシンを実行すると以下のように正常に終了しました。
X-Rayトレースからタイムラインを確認すると、確かに並列で実行されていることが確認できます。
実行時のCloudWatchメトリクスは以下のようになっていました。
CloudWatch Logs Insightsで集計した結果は以下の通りです。
| フィールド | 値 |
|---|---|
| duration_avg | 245.7216 |
| duration_max | 479.79 |
| duration_min | 93.94 |
| duration_pct25 | 164.38 |
| duration_pct50 | 222.96 |
| duration_pct75 | 321.28 |
| duration_count | 100 |
| initDuration_avg | 666.3295 |
| initDuration_max | 747.01 |
| initDuration_min | 569.76 |
| initDuration_pct25 | 643.28 |
| initDuration_pct50 | 669.78 |
| initDuration_pct75 | 687.03 |
| initDuration_count | 43 |
initDuration_countが43になっていることから43回コールドスタートが発生したことが分かります。
各パターンの結果比較
各パターンの結果比較します。
| フィールド | パターン1 | パターン2 | パターン3 | パターン4 |
|---|---|---|---|---|
| duration_avg | 45.8541 | 119.3956 | 113.3586 | 245.7216 |
| duration_max | 237.3 | 261.13 | 341.75 | 479.79 |
| duration_min | 13.29 | 82.56 | 25.12 | 93.94 |
| duration_pct25 | 23.33 | 94.8905 | 61.7404 | 164.38 |
| duration_pct50 | 34.88 | 105.2851 | 97.3888 | 222.96 |
| duration_pct75 | 51.42 | 124.7844 | 146.7171 | 321.28 |
| duration_count | 100 | 100 | 100 | 100 |
| initDuration_avg | 696.14 | 690.17 | 801.1223 | 666.3295 |
| initDuration_max | 696.14 | 690.17 | 1273.24 | 747.01 |
| initDuration_min | 696.14 | 690.17 | 616.83 | 569.76 |
| initDuration_pct25 | 696.14 | 690.17 | 729.95 | 643.28 |
| initDuration_pct50 | 696.14 | 690.17 | 794.79 | 669.78 |
| initDuration_pct75 | 696.14 | 690.17 | 842.5 | 687.03 |
| initDuration_count | 1 | 1 | 30 | 43 |
直列実行内、並列実行内で見比べると、duration_から始まる項目はRDS Proxyの接続をhandlerの外側で実行するLambda関数の方が処理時間が短いですね。
また、直列実行と並列実行で比較すると、ウォームスタートの差で直列実行の方が処理時間が短くなっていることも分かります。
ただし、各パターンのステートマシンの開始から終了までの時間を比較すると、直列実行よりも並列実行の方が圧倒的に短いことが分かります。並列実行の場合はLambda関数が30多重以上で実行されていたので、ウォームスタートの差が全体の処理完了までに与える影響を小さくしていたと判断できます。
| パターン | ステートマシンの開始から終了までの時間 |
|---|---|
| パターン1 | 24秒 |
| パターン2 | 30秒 |
| パターン3 | 4秒 |
| パターン4 | 4秒 |
パフォーマンスを優先するならRDS Proxyの接続を使い回した方が良さそう
Lambda関数のhandlerの外側でRDS Proxyの接続をした場合の処理時間を計測してみました。
Lambda関数のhandlerの外側でRDS Proxyに接続することで、RDS Proxyへのコネクションを使い回すことができ、後続のLambda関数の処理時間を減らすことが確認できました。
Lambda関数のhandlerの外側でRDS Proxyの接続をする場合の注意点は接続を確立したままになる点です。そのため、長時間接続が放置されないようにアイドルクライアントの接続タイムアウトを適切な時間にする必要があります。(デフォルトは30分で最大8時間)
この記事が誰かの助けになれば幸いです。
以上、AWS事業本部 コンサルティング部の のんピ(@non____97)でした!
